By

Contents
  1. 1. 如何生成GC日志文件
  2. 2. 备注
  3. 3. 流程
  4. 4. 配置jvm 参数
  5. 5. 查看内存分配
  6. 6. 查看和分析 GC日志
  7. 7. 测试环境实战
    1. 7.1. 更换测试环境的JDK路径
    2. 7.2. JVM 参数分析 jinfo -flags pid
    3. 7.3. GC策略查询 jmap -heap pid
    4. 7.4. 空间分配容量查询
    5. 7.5. 内存实际使用和GC情况
    6. 7.6. 利用jmap导出并查看dump包
    7. 7.7. gc log分析
    8. 7.8. 性能优化
    9. 7.9. 深层优化
  • 虚拟机环境的JVM讲解
  • 测试环境的JVM讲解

如何生成GC日志文件

  1. -verbose:gc -Xloggc:/usr/local/jvmlog/gc.log
    -XX:+PrintGCTimeStamps -XX:+PrintGCDetails

  2. ./jmap -dump:format=b,file=t/usr/local/tmp/test.dump pid
    生成dump文件

  3. 通过自带的visualVM生成即时的快照dump文件

  4. 启动server配置 OOM自动生成快照dump文件

其他相关参数调优：
https://www.cnblogs.com/redcreen/archive/2011/05/04/2037057.html

备注

  • CMS 情况我试过了，分配的不按这个逻辑来啊，默认newratio是2，但是分配了500M给堆区，但是老年代直接占了413M，比例成了5:1了

  • 不同GC回收器生成的日志格式都不一样，要具体分析

流程

运行在linux虚拟机 物理内存4G的环境下，JDK1.7

  • 配置 tomcat的catAlina.sh的 jvm 参数
  • 启动之后，看内存的分配，和GC回收器的种类
  • 查看和分析GC日志

配置jvm 参数

在catalina.sh 的头部配置参数。

  • 设置堆初始化大小500M， 永久代初始化64M
  • 设置年轻代 Eden:S0=4
  • 设置日志输出文件渠道
  • 设置S（to）进入老年代的年龄是15次
    JAVA_OPTS="-server -Xms500m -Xmx1500m  -XX:PermSize=64m -XX:MaxPermSize=256m -XX:SurvivorRatio=4
    -verbose:gc -Xloggc:/usr/local/jvmlog/gc.log 
    -Djava.awt.headless=true 
    -XX:+PrintGCTimeStamps -XX:+PrintGCDetails 
    -Dsun.rmi.dgc.server.gcInterval=600000 -Dsun.rmi.dgc.client.gcInterval=600000
    -XX:MaxTenuringThreshold=15"

查看内存分配

查看堆内存信息
堆内存信息

  • 回收器类型 JDK 1.7 默认是 Mark Sweep Compact
  • 最大堆区：设置的1500M
  • 最小500M， 而默认的新生代 和老年代的比例是2，所以 新生代的大小是500/3=166M
  • Eden:S=4,所以S0=166/6=27.75， Eden: 27.75*4=111M， 111 +27.75 +27.75=166

查看和分析 GC日志

MinorGClog分析

  • 首先看次数，可以看出Yong GCT 为18次，而日志中刚好也是18行，默认Yong GC 是简写的，FullGC才会写全称。

  • 分析第一行 Eden+S0 从113792k MinorGC 后变成13544K，压缩后的总容量为142208（也就是111M+27.75M=138M*1024= 141312K）

测试环境实战

更换测试环境的JDK路径

因为之前用的是很老的 1.6的JDK版本，都没有各种工具的，所以修改 nano catalina.sh 文件，添加了下面的，指定了 JDK 路径，而不是用java home的 1.6的JDK，结果启动成功了

set JAVA_HOME=/usr/developer/nexus/jdk1.7.0_67
set JRE_HOME=/usr/developer/nexus/jdk1.7.0_67/jre

JVM 参数分析 jinfo -flags pid

./jinfo -flags 20817

主要参数：
-XX:PermSize=512M -XX:MaxPermSize=4096M
分析：
1） 没有记录JVM日志的操作，而且没有内存溢出的报告
2） 而且没有设置JVM Xms Xmx的大小，浪费了
3） Perm区由没有必要设置为这么大？

测试

GC策略查询 jmap -heap pid

Parallel GC 4线程，吞吐量优先。
问题：
1） 没有默认赋值 最小空闲 和最大空闲比例，系统不会跟随工作量调整JVM的堆区的大小，只有当Minor GC的时候 才会resize，而且一旦上调之后便不会下调，因为MaxHeaop是100，也就是是否有必要动态调整JVM 堆区的大小，其实这和 Xmn Xmx值设置为一样是一个道理。但是设置 Xmn Xmx可以避免前期因为太小而FullGC的情况，优化为40% 70%
2） 很奇怪没有按照 8:1的比例，而且S from 和S to大小不一样 S0：S1的容量是 2：1，但是有一个区是0的没错。
3） Perm区 使用率只有24%，有点浪费空间，很好奇为什么设置这么大
测试
测试

空间分配容量查询

./jstat -gccapacity 20817
因为采用的是 Pallel GC所以是以吞吐量为优先，根据参数动态调整。
测试

内存实际使用和GC情况

1） gcutil 可以看出 利用率最低的就是 Perm区了，只有24%，没必要分配这么大的空间给他。
2） FGC的耗时有点长，平均达到了2s，有必要看一下详细情况，以及check下 nginx的超时设置，会不会导致2s的访问失败
测试

利用jmap导出并查看dump包

./jmap -dump:live,format=b,file=/usr/developer/huangForBackUp/testEnv.bin 20817

gc log分析

测试

性能优化

1） 添加jvm日志输出，更加仔细的查看每次GC的活动
2） check nginx的超时设置，从而判断有没有失败的请求（这是GCT的上限）（链接nginx上限是3s 钟 后台处理 和 后台返回的超时时间各位300s，所以只要GC时间在3s以内就几乎不会请求失败）
3） 根据GC日志降低 FULLGC的次数和最大时长

解决方案：实际上通过调大Xms 避免了最开始期间的FULLGC，其实意义并不大。因为老的JVM方案，经过1个小时之后JVM自动也调整到这个水平。或者可以说本来就已经到了很棒的水平了

1） 添加日志输出，在catelina.sh 中添加参数
JAVA_OPTS=”$JAVA_OPTS -server -Xms2048m -XX:PermSize=256M -XX:MaxPermSize=1024M
-verbose:gc -Xloggc:/usr/developer/huangForBackUp/testgc.log
-XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:MaxTenuringThreshold=15”
2） 初始化设置Xms的大小 Xmx的大小，以及ratio，因为最开始的2次FullGC都是因为初始化的永久代太小导致的，后面等永久代保存好了之后，就不容易FULLGC了。
看日志里面 Parellel稳定期间 分配给年轻代的大小稳定在 1.3G左右，老年代的大小在700M左右，直接最小为2G，最大4G
其实通过日志可以发现在2G大小的时候，Minor GC的时间稳定在 0.35秒左右，是一个可以接受的时间。

3） 调优后 初期表现良好，当JVM启动2分钟之后开始稳定了

测试

深层优化

网站类型的服务器应该优先采用CMS作为垃圾回收类型
没有大量的数据很难做出调优方案，因为本来就已经性能不错了

Contents
  1. 1. 如何生成GC日志文件
  2. 2. 备注
  3. 3. 流程
  4. 4. 配置jvm 参数
  5. 5. 查看内存分配
  6. 6. 查看和分析 GC日志
  7. 7. 测试环境实战
    1. 7.1. 更换测试环境的JDK路径
    2. 7.2. JVM 参数分析 jinfo -flags pid
    3. 7.3. GC策略查询 jmap -heap pid
    4. 7.4. 空间分配容量查询
    5. 7.5. 内存实际使用和GC情况
    6. 7.6. 利用jmap导出并查看dump包
    7. 7.7. gc log分析
    8. 7.8. 性能优化
    9. 7.9. 深层优化